Add prefix to java util logging logger names #136064
Conversation
The bridge between Java util logging and Log4j works by mapping each log message received in JUL to a log event in log4j. The JUL bridge tests check that messages of varying log levels are emitted. Unfortunately this has a bad interaction with entitlements and tests. When a class (eg Regex, used by the test mock logger) is loaded, entitlements looks at that class to see if it should transform it. It then logs a trace message to say it will not be transformed. Yet if a class is loaded late, like Regex is, entitlements will emit this trace log message while log4j is already appending the original test log message. That in turn causes a status log message indicating a recursive call to the mock appender, which tests do not expect, and the test fails. This commit sidesteps the issue by adding a special prefix, `jul`, to the mapping between logger names in JUL and log4j. By not setting the log level of the root log4j logger, the entitlements trace message is never emitted.
rjernst
added
:Core/Infra/Logging
|
Pinging @elastic/es-core-infra (Team:Core/Infra) |
|
Really not sure what the right solution to this is. We've seen similar problems with logging in To be honest, I'm a bit sceptical about prefixing JUL loggers. It will make those a lot harder to discover because it's not a 1:1 match anymore from code to Kibana filters. Why do we log at the root level for JUL? Can't we use a decent logger name there to achieve the same by not having to temper the root logger level? |
|
Not objecting to this PR and I'm ok to move forward this way, but my preference would be to change the test rather than the bridge. f we replaced the JUL logger with a log4j logger I'm rather sure the result wouldn't be any different causing recursive calls to the appender (if reducing the root log level enough). Having said that, the prefix doesn't seem to prevent the issue but rather just make the test pass. |
We log at whatever level the logger is. There is the JUL logger, and the log4j logger. We grab the JUL root logger so we can capture all JUL log messages. How that maps to a log4j logger is the point of this PR. Currently we map it directly, so if you have code in the same package that uses ES/log4j logger, as well as JUL logger, it will show the same logger name, you won't even know you used JUL. By adding a prefix we can detect when JUL is actually used.
Can you explain this a bit more? We don't use JUL anywhere in ES, so this would only be from third party libraries. So I would expect the filters used for Kibana already don't cover this (ie they won't begin with With that said, I'm not sold on this either, I'm presenting it as one possible solution. I think the distinction may make sense on its own, but I see there are tradeoffs too. |
Sorry, my bad. I meant to ask why the JUL bridge tests are logging using the root
Let's say I investigate an issue caused by such a 3rd party lib. If I find a logger in their code that could provide additional insights, I'd want to search for that - or more generally search for any logger matching the package names of that lib. It would be rather confusing having to know that the lib is using JUL and logger names need to be prefixed because of that. This change certainly wouldn't impact existing dashboards or alerts. It might just throw of devs when doing ad-hoc investigations. |
The bridge between Java util logging and Log4j works by mapping each log message received in JUL to a log event in log4j. The JUL bridge tests check that messages of varying log levels are emitted.
Unfortunately this has a bad interaction with entitlements and tests. When a class (eg Regex, used by the test mock logger) is loaded, entitlements looks at that class to see if it should transform it. It then logs a trace message to say it will not be transformed. Yet if a class is loaded late, like Regex is, entitlements will emit this trace log message while log4j is already appending the original test log message. That in turn causes a status log message indicating a recursive call to the mock appender, which tests do not expect, and the test fails.
This commit sidesteps the issue by adding a special prefix,
jul, to the mapping between logger names in JUL and log4j. By not setting the log level of the root log4j logger, the entitlements trace message is never emitted.